[DIRMINA-1146] Pass message to next filter in SslFilter by the-thing · Pull Request #61 · apache/mina

the-thing · 2026-09-08T16:58:13Z

It will also help fix quickfix-j/quickfixj#406

Changes

Currently none of the EncryptedWriteRequest instances have parent message provided which means that original message and request is always the same instance. We must pass all the messages down the chain.

org.apache.mina.filter.ssl.SslFilter now also passes the encrypted message down the filter chain, eventually reaching org.apache.mina.core.filterchain.DefaultIoFilterChain.TailFilter which will increase the written message count and also decrement scheduled message count.

Obviously this change will have an impact filters configured between org.apache.mina.filter.ssl.SslFilter and org.apache.mina.core.filterchain.DefaultIoFilterChain.TailFilter, but I think users should make changes accordingly in this case.

elecharny · 2026-09-09T15:14:24Z

Hi,

thanks for the proposed patch.
I have tested it, and it seems we have a test failure in mina-example:

[ERROR] Tests run: 2, Failures: 0, Errors: 1, Skipped: 0, Time elapsed: 0.246 s <<< FAILURE! -- in org.apache.mina.example.echoserver.ssl.SslFilterTest
[ERROR] org.apache.mina.example.echoserver.ssl.SslFilterTest.testMessageSentIsCalled_With_SSL -- Time elapsed: 0.089 s <<< ERROR!
java.net.SocketException: Connection reset
	at java.base/sun.nio.ch.NioSocketImpl.implRead(NioSocketImpl.java:316)
	at java.base/sun.nio.ch.NioSocketImpl.read(NioSocketImpl.java:354)
	at java.base/sun.nio.ch.NioSocketImpl$1.read(NioSocketImpl.java:798)
	at java.base/java.net.Socket$SocketInputStream.implRead(Socket.java:974)
	at java.base/java.net.Socket$SocketInputStream.read(Socket.java:964)
	at java.base/sun.security.ssl.SSLSocketInputRecord.read(SSLSocketInputRecord.java:489)
	at java.base/sun.security.ssl.SSLSocketInputRecord.readHeader(SSLSocketInputRecord.java:483)
	at java.base/sun.security.ssl.SSLSocketInputRecord.bytesInCompletePacket(SSLSocketInputRecord.java:70)
	at java.base/sun.security.ssl.SSLSocketImpl.readApplicationRecord(SSLSocketImpl.java:1461)
	at java.base/sun.security.ssl.SSLSocketImpl$AppInputStream.read(SSLSocketImpl.java:1068)
	at java.base/sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:279)
	at java.base/sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:322)
	at java.base/sun.nio.cs.StreamDecoder.read(StreamDecoder.java:186)
	at java.base/java.io.InputStreamReader.read(InputStreamReader.java:183)
	at java.base/java.io.BufferedReader.fill(BufferedReader.java:166)
	at java.base/java.io.BufferedReader.readLine(BufferedReader.java:333)
	at java.base/java.io.BufferedReader.readLine(BufferedReader.java:400)
	at org.apache.mina.example.echoserver.ssl.SslFilterTest.testMessageSentIsCalled(SslFilterTest.java:109)
	at org.apache.mina.example.echoserver.ssl.SslFilterTest.testMessageSentIsCalled_With_SSL(SslFilterTest.java:79)
	at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:104)
	at java.base/java.lang.reflect.Method.invoke(Method.java:565)
	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:59)
	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:56)
	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
	at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26)
	at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
	at org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306)
	at org.junit.runners.BlockJUnit4ClassRunner$1.evaluate(BlockJUnit4ClassRunner.java:100)
	at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:366)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:103)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:63)
	at org.junit.runners.ParentRunner$4.run(ParentRunner.java:331)
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:79)
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:329)
	at org.junit.runners.ParentRunner.access$100(ParentRunner.java:66)
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:293)
	at org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306)
	at org.junit.runners.ParentRunner.run(ParentRunner.java:413)
	at org.apache.maven.surefire.junit4.JUnit4Provider.execute(JUnit4Provider.java:316)
	at org.apache.maven.surefire.junit4.JUnit4Provider.executeWithRerun(JUnit4Provider.java:240)
	at org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:214)
	at org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:155)
	at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:385)
	at org.apache.maven.surefire.booter.ForkedBooter.execute(ForkedBooter.java:162)
	at org.apache.maven.surefire.booter.ForkedBooter.run(ForkedBooter.java:507)
	at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:495)

[INFO] Running org.apache.mina.example.echoserver.ConnectorTest
[WARNING] Tests run: 3, Failures: 0, Errors: 0, Skipped: 1, Time elapsed: 0.386 s -- in org.apache.mina.example.echoserver.ConnectorTest
[INFO] 
[INFO] Results:
[INFO] 
[ERROR] Errors: 
[ERROR]   SslFilterTest.testMessageSentIsCalled_With_SSL:79->testMessageSentIsCalled:109 » Socket Connection reset
[INFO] 
[ERROR] Tests run: 13, Failures: 0, Errors: 1, Skipped: 1
[INFO] 
[INFO] ------------------------------------------------------------------------
[INFO] BUILD FAILURE
[INFO] ------------------------------------------------------------------------
[INFO] Total time:  12.895 s
[INFO] Finished at: 2026-09-09T17:08:03+02:00
[INFO] ------------------------------------------------------------------------

I'm not sure it's related, but I don't have this failure when I don't apply your proposed patch.

I have tested with Java 17 and 25.

If I run the exact same class test in eclipse, it passes green... Go fish...

I'm trying to see what could be the cause of this issue (beside the fact the connection has been closed)

the-thing · 2026-09-09T15:37:51Z

Hello,

I was getting slightly different error for org.apache.mina.example.echoserver.ssl.SslFilterTest before applying my change onto 2.2.x branch - same failure line SslFilterTest.java:109

Windows 11 / temurin / Java 17

[ERROR] Tests run: 2, Failures: 0, Errors: 1, Skipped: 0, Time elapsed: 0.151 s <<< FAILURE! -- in org.apache.mina.example.echoserver.ssl.SslFilterTest
[ERROR] org.apache.mina.example.echoserver.ssl.SslFilterTest.testMessageSentIsCalled_With_SSL -- Time elapsed: 0.035 s <<< ERROR!
java.lang.NullPointerException: Cannot invoke "String.equals(Object)" because the return value of "java.io.BufferedReader.readLine()" is null
	at org.apache.mina.example.echoserver.ssl.SslFilterTest.testMessageSentIsCalled(SslFilterTest.java:109)
	at org.apache.mina.example.echoserver.ssl.SslFilterTest.testMessageSentIsCalled_With_SSL(SslFilterTest.java:79)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:569)
	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:59)
	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:56)
	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
	at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26)
	at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
	at org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306)
	at org.junit.runners.BlockJUnit4ClassRunner$1.evaluate(BlockJUnit4ClassRunner.java:100)
	at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:366)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:103)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:63)
	at org.junit.runners.ParentRunner$4.run(ParentRunner.java:331)
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:79)
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:329)
	at org.junit.runners.ParentRunner.access$100(ParentRunner.java:66)
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:293)
	at org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306)
	at org.junit.runners.ParentRunner.run(ParentRunner.java:413)
	at org.apache.maven.surefire.junit4.JUnit4Provider.execute(JUnit4Provider.java:316)
	at org.apache.maven.surefire.junit4.JUnit4Provider.executeWithRerun(JUnit4Provider.java:240)
	at org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:214)
	at org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:155)
	at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:385)
	at org.apache.maven.surefire.booter.ForkedBooter.execute(ForkedBooter.java:162)
	at org.apache.maven.surefire.booter.ForkedBooter.run(ForkedBooter.java:507)
	at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:495)

I also consistently get an error on 2.2.x

org.apache.mina.transport.AbstractFileRegionTest#testSendLargeFile

Let me have a look as well.

elecharny · 2026-09-09T16:48:26Z

I also have the same issue with the NPE when the message is sent back to the IoHandler.
It has all to do with the the fact that the socket has been shut down, so the input reader can't send back anything but null.

Now to understand why the socket has been closed...

elecharny · 2026-09-09T21:56:03Z

ok, I think the issue is on the client side.

On the server, the connection get closed by the client thus it can't return anything to the client.

I still have no idea why the client closes the connection, I keep digging.

the-thing · 2026-09-10T04:44:41Z

@elecharny

org.apache.mina.example.echoserver.ssl.SslFilterTest.EchoHandler#messageSent

if (sentMessages.size() >= 2) {
    session.closeNow();
}

Test needs modification, but for SSL sometimes I get 3 messages in total, sometimes 4.

the-thing · 2026-09-10T05:03:47Z

Looks better now with additional timeout. We send SSL handshake messages now - so total 4 messages in SSL.

Handshake ServerHello

write_handshake_loop() - result HeapBuffer@69fcb628[...lim=1427...]
ack WriteRequest: HeapBuffer@69fcb628[...]

Handshake Finishe

write_handshake_loop() - bytes-produced 1204, status OK, handshake FINISHED
forward_events() - dispatching event SECURED
ack WriteRequest: HeapBuffer@59b132f1[...]

Test message "test-1"

SERVER: ... write WriteRequest: test-1
ack WriteRequest: HeapBuffer@5e462c04[...lim=45...]

Closed

receive_loop() - bytes-consumed 40, status CLOSED, handshake NEED_WRAP
write_handshake_loop() - status CLOSED, handshake NOT_HANDSHAKING
ack WriteRequest: HeapBuffer@5ff5fe15[...lim=40...]
SERVER: Session ... closed

elecharny · 2026-09-10T06:14:21Z

Ok, I was totally wrong. The server do close the connection, and more specifically the messageReceive() method does it when it has received 2 messages.

The key here is that the IoHandler receives Handshake massages, which is totally wrong. So it all has to do with the change done. We have to find a way to not send HS messages to the IoHandler.

Here are the logs:

------------------------------------Message sent: HeapBuffer@5ab35b18[pos=0 lim=1427 cap=33418: 16 03 03 00 7A 02 00 00 76 03 03 1B 0E 3F 5E D7]

and then later on:

------------------------------------Message sent: HeapBuffer@63d87619[pos=0 lim=1210 cap=33418: 17 03 03 04 B5 27 B5 4E 9A 80 91 A9 A5 22 55 A1]

I have changd the messageSent method to print that logs:

        @Override
        public void messageSent(IoSession session, Object message) throws Exception {
            System.out.println( "------------------------------------Message sent: " + message );
            sentMessages.add(message.toString());

            if (sentMessages.size() >= 2) {
                session.closeNow();
            }
        }

and we can clearly see that we are dealing with TLS messages: 16 is for a HS TLS message, 17 is the wrapped message, crypted.

the-thing · 2026-09-10T06:30:50Z

Yes that is correct. We had SSL related messages via org.apache.mina.core.service.IoHandler#messageSent.

The key here is that the IoHandler receives Handshake massages, which is totally wrong.

I was wondering if this is going to be a requirement. Initial SSL Hello messages are easy to detect and drop by looking at the TLS header, but SSL FINISHED / CLOSED is not.

elecharny · 2026-09-10T07:29:20Z

Actually, in the IoHandler, we should only deal with message that the application has sent. TLS messages are technical, and they should not be visible. So there is no reason to propagate them at all.

Two options here:

either we don't generate a messageSent event when we are dealing with TLS HS
or we block them in the SslFilter.messageSent() (like what was done somehow, but IMO wit a bit brutal solution, thus your proposal which solve the original issue, but sadly has a side effect...)

I clearly don't like the first option because that would mean deep in the Processor class where we fire this event, we have to know that TLS has been set. I'd rather take the other road, may be by creating a specific HandshakeWriteRequest which would inherit from WriteRequest, and checking if we are dealing with such flavor of WriteRequest in the SslFilter.messageSent() method...

the-thing · 2026-09-10T07:32:51Z

Ok. I misunderstood the root cause of the problem.

My original assumption was that the application level messages were the problem, but it seems that SSL messages are. org.apache.mina.core.filterchain.DefaultIoFilterChain.HeadFilter increases the counter for all messages (even SSL), but org.apache.mina.core.filterchain.DefaultIoFilterChain.TailFilter is never reached because of org.apache.mina.filter.ssl.SslFilter#messageSent filtering.

SslFilter may stay the same, but org.apache.mina.core.filterchain.DefaultIoFilterChain.HeadFilter needs to skip these and not increment the counter.

I have a feeling increaseScheduledWriteBytes in org.apache.mina.core.filterchain.DefaultIoFilterChain.HeadFilter#filterWrite probably needs to be filtered as well.

I pushed and squashed the latest changes. Let me know how you see it.

elecharny · 2026-09-10T07:46:04Z

Mina is a complicated beast ;-)

I'll have a look at your last commit.

Thanks!

elecharny · 2026-09-10T10:59:39Z

Looks good to me (after a late battle with MDC, which does not really liked the added logs I put in AbstractPollingIoProcessor, something I have to fix later).

Many thanks for your patch, it has been applied!

the-thing · 2026-09-10T11:01:28Z

@elecharny

Thanks for looking and help investigating as well.

Any plans for the next 2.2.x release? Probably not soon.

elecharny · 2026-09-10T11:06:59Z

@the-thing could you send me your email on elecharny@apache.org, please?

Many thanks!

the-thing marked this pull request as draft September 9, 2026 16:10

the-thing force-pushed the ssl-filter-next-filter-fix branch from 994374a to e1f4ba9 Compare September 10, 2026 05:30

the-thing force-pushed the ssl-filter-next-filter-fix branch from e1f4ba9 to e20bb25 Compare September 10, 2026 07:26

SslFilter pass message to next filter

50a54f6

the-thing force-pushed the ssl-filter-next-filter-fix branch from e20bb25 to 50a54f6 Compare September 10, 2026 07:32

elecharny closed this Sep 10, 2026

the-thing mentioned this pull request Sep 10, 2026

[DIRMINA-1146] Additional unit test checks #62

Merged

Uh oh!

Conversation

the-thing commented Sep 8, 2026

Uh oh!

elecharny commented Sep 9, 2026

Uh oh!

the-thing commented Sep 9, 2026

Uh oh!

elecharny commented Sep 9, 2026

Uh oh!

elecharny commented Sep 9, 2026

Uh oh!

the-thing commented Sep 10, 2026

Uh oh!

the-thing commented Sep 10, 2026 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

elecharny commented Sep 10, 2026 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

the-thing commented Sep 10, 2026

Uh oh!

elecharny commented Sep 10, 2026

Uh oh!

the-thing commented Sep 10, 2026

Uh oh!

elecharny commented Sep 10, 2026

Uh oh!

elecharny commented Sep 10, 2026

Uh oh!

the-thing commented Sep 10, 2026

Uh oh!

elecharny commented Sep 10, 2026

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

2 participants

the-thing commented Sep 10, 2026 •

edited

Loading

elecharny commented Sep 10, 2026 •

edited

Loading